Yioop v10 — pollett.org Log Debug Plan

Arc Post-Mortem Summary. A triage of the pollett.org production PHP error log from 16-Jun-2026. It fixed a recurring “Undefined array key USER_ID” warning in two public resource-serving methods, hardened and audited the related paths, and chased down an HTTP/2 partial-transfer bug on large responses whose root cause was a writable-set snapshot race in the cooperative server. Fixes landed in HEAD to reach production on its next pull.

Triage of the production PHP error log from pollett.org (16-Jun-2026). The running server pulled the repo the evening before, so it is on commit 5f6f2b4 (SocialComponent.php at 12666 lines) — that is how the logged line numbers (12075 / 12171) map back to the source. The mail arc has since shrunk that file, so the same code now lives at 10240 / 10336 in HEAD; fixes land in HEAD and reach production on its next pull.

  1. Recurring “Undefined array key USER_ID” warning (SocialComponent.php, two sites).
    1. Root cause: two public wiki/group resource-serving methods call checkAuthRequirement($data, $_SESSION['USER_ID']) without a guard. An anonymous (not-logged-in) visitor or bot has no USER_ID in the session, so PHP 8.5 warns on every such request — hence the all-day recurrence.
    2. It was also a latent auth bug: the undefined value is null, and null != C\PUBLIC_USER_ID, so a guest was not being treated as the public user in the require-signin check.
    3. Fixed: both sites now pass $_SESSION['USER_ID'] ?? C\PUBLIC_USER_ID, the idiom already used throughout the file. checkAuthRequirement's own docblock names PUBLIC_USER_ID as the guest sentinel, so this clears the warning and corrects the guest path.
  2. Fixed “SSL: Connection reset by peer” in stream_get_contents (WebSite.php:2860, parseH1Request).
    1. A client / bot dropped the TLS connection while the server was still reading the request body. Transient and environmental, not a server fault (2 occurrences all day).
    2. Fixed: the request-body read is now wrapped in a temporary error handler that swallows only the “reset by peer” notice and lets every other warning through, then restores the previous handler. No @ suppression; this mirrors the intent of the existing write-side suppression near WebSite.php:4942.
  3. Fixed (drain) Memory fatal — 2 GB exhausted, tried to allocate ~1.5 GB (WebSite.php:4942, output drain).
    1. A single response of ~1.5 GB was held entirely in memory ($out_streams[DATA][$key]), and the drain did substr($data, $offset) — copying the whole unsent tail on each fwrite. That ~1.5 GB copy on top of the buffer already in memory is what crossed the 2 GB limit. One occurrence.
    2. Fixed: the drain now copies at most one MAX_IO_LEN (128 KB) block per pass instead of the entire tail — substr($data, $offset, $chunk_len). The socket only accepts a bounded amount per writable event anyway, so this costs no throughput; $offset still advances and the periodic compaction still reclaims the sent prefix. Peak memory is now the buffer itself, never doubled, so a large response drains instead of OOMing.
    3. Where the 1.5 GB came from — corrected: the access log at the crash second shows public-user bots crawling wiki history&show=<revision> on the public group (pages 4/3). But that path is not the 1.5 GB source: wiki content is capped at MAX_GROUP_PAGE_LEN (512 KB) on save (SocialComponent.php:7817) and WikiParser::parse truncates render output to ~472 KB when handle_big_files is false (the show path). So each history-show response is ≤~472 KB. The 1.5 GB buffer is a different request — most plausibly a large wiki resource / attachment served whole and draining slowly to a stalled client, with the history-crawling bots as concurrent memory pressure.
    4. NEXT (open) the drain fix neutralizes the OOM regardless of producer. To stop a ~1.5 GB body being generated/buffered at all, pinpoint the producer: check pollett.org for a large file/resource on the public wiki and the access log just before the crash second. Likely follow-up: stream large resource bodies rather than buffering them whole.
    5. Resolved (producer): the offset/limit resource branch now streams. A second 2 GB OOM on 2026-06-22 (tried to allocate ~1.28 GB, in WebSite.php on the response side, while a flood of bots crawled wiki history and source) traced to the one resource-serving branch that still read whole. ResourceController::get serves a byte window requested with o and l (the machine-to-machine sync path, and reachable on any public resource) by reading the span with file_get_contents($path, false, null, $offset, $limit). The limit comes straight off the request as an int with no cap, so a large span (a 50 MB sync chunk, or a crafted request naming a whole multi-hundred-megabyte file) was read entire into memory and then copied again into the server's response buffer, and that copy is what crossed the 2 GB process limit and killed the single-process server. The other three serve branches (HTTP Range, small files under MAX_RESOURCE_SERVE_LEN, and large no-range files) already stream or are bounded; this was the lone whole-read. It now streams the same window in RESOURCE_STREAM_BLOCK_LEN blocks through the same web_site stream generator the Range and large-file branches use, with the headers left exactly as before, so the bytes and response are identical and memory stays bounded to one block. The exact crash request is not in the log tail because a request that dies mid-serve never reaches the post-serve access-log write; this fix removes the only path that could have produced that allocation.
    6. Hardening (defense-in-depth): per-connection HTTP/2 memory ceilings. The producer fix above removes the request that built the oversized body, but the crash also showed the server had no ceiling on how much it would hold for a single HTTP/2 connection. Because H2 multiplexes every stream's response onto one per-connection outbound buffer (queueResponseData appends), and each dispatched stream's body waits in pending_send until its flow-control window lets it pump, a client that pipelines requests faster than it reads the replies could grow that one connection's state without bound — the server advertised MAX_CONCURRENT_STREAMS=100 but did not enforce it. Now a new stream is refused with RST_STREAM(REFUSED_STREAM) once the connection is at 100 open streams or its buffered-byte ceiling (H2_MAX_CONN_BUFFER, 64 MB: queued unsent + each stream's pending response body + each stream's still-arriving request body, summed by h2ConnectionBacklog). So no single connection can exhaust the process regardless of which route produced the body. A conforming client never reaches the limit since it honors the advertisement.
    7. Audit of the ignored H2 settings for other exhaustion paths. The SETTINGS handler accepts but ignores most peer settings; checked each for an unbounded structure a client could grow. Incoming frames are already capped (oversized frame → GOAWAY FRAME_SIZE_ERROR; request body → MAX_REQUEST_LEN), and the header block is not accumulated across frames, so those are bounded. One gap remained: pending_stream_window_credit stashes a WINDOW_UPDATE arriving for a stream whose send window is not yet registered, keyed by stream id, and the new byte ceiling does not count these small entries — so a client sending WINDOW_UPDATE for many never-opened stream ids could grow that map without bound. Now it is capped at MAX_CONCURRENT_STREAMS distinct streams (more than a connection can ever have open at once); a client exceeding that is crediting streams it never opened, which is treated as a PROTOCOL_ERROR (GOAWAY).
  4. Fixed MediaUpdater fatal — BulkEmailJob could not load SmtpClient (require of a missing mail/Utility.php).
    1. The mail-library relocation moved SmtpClient into src/library/mail/ but left two breaks the daemon path tripped over. First, an inline require_once __DIR__ . "/Utility.php" now resolved to mail/Utility.php (one level too deep) — file not found, fatal at load. Second, hidden behind that, the class still called crawlLog, changeInMicrotime and setWorldPermissions unqualified; from the new ...\library\mail namespace those resolve to undefined functions, so the first such call would have fataled even once the file loaded. Web paths never hit this because index.php loads Utility; the MediaUpdater daemon did not.
    2. Fixed: a library class should not load Utility, so the inline require is gone; the MediaUpdater daemon now requires Utility like the other executables, and SmtpClient imports library as L and calls L\crawlLog etc. A sweep of the rest of the mail / ACME / media-job v10 classes found no other stray requires.
  5. HTTP/2 partial transfer on responses past the per-stream window (the Magazines page). A wiki page larger than the client's initial per-stream receive window (Firefox starts a connection at 131072 bytes) loaded intermittently: the same page would succeed on one request and fail with NS_ERROR_NET_PARTIAL_TRANSFER on the next. Smaller pages, which fit inside the initial window and finish in one burst, were never affected.
    1. What the traces established. The client does extend windows, generously: it raises SETTINGS_INITIAL_WINDOW_SIZE mid-connection (seen as peer_initial_window jumping from 131072 to 6291456) and sends large per-stream WINDOW_UPDATE frames (+12451840). So a parked stream is meant to resume the moment that credit lands. The behaviour we never saw was the credit failing to arrive; what we saw was credit arriving and the tail still not going out on the failing loads. Note: a separate class of connection advertises an initial window of 0 and grants entirely per stream — for those, peer_initial_window is genuinely 0 and seeding the send window to 0 is correct (the default-window fallback only applies when the value is null, never when it is a real 0).
    2. Dead end (recorded so it is not retried). Pacing a large body out in frame-sized blocks through the streaming generator does not help by itself: the streaming path is gated by the very same per-stream send window as a whole-body send, so it cannot push past an exhausted window any more than sendH2Body can. Streaming does not raise the window. Routing the page through it is not the lever.
    3. Root cause: a writable-set snapshot race in the event loop. Each loop pass snapshots the set of connections with unsent response bytes before select, then after select reads inbound frames and finally drains that snapshot. When a parked stream last drained its window-sized slice it was removed from the writable set (shutdownHttpWriteStream, correct — there was nothing to write while its send window sat at zero). The credit (WINDOW_UPDATE or raised SETTINGS) then arrives in the read phase and re-pumps the stream, queueing the rest of the body and re-arming the connection — but that happens after the snapshot was taken, so the drain step skips it. The bytes wait for the next select cycle; if the peer has stopped reading by then, the tail never leaves and the transfer ends partial. Whether the window came back in time was a race, which is exactly why the same page passed on one load and failed on the next.
    4. Fixed: the drain step now operates on the live set of connections that have unsent bytes at that point in the tick rather than the pre-read snapshot, so a stream re-pumped by a just-read flow-control frame flushes in the same pass. out_streams holds only connections with bytes still to send, and a socket that is not yet writable simply takes nothing this pass and is retried, so draining the live set is safe.
  6. Two further crashes, 2026-07-03 and 2026-07-04. The error log shows three identical fatals: the 2 GB process limit exhausted while allocating ~1.3 MB in PackedTableTools::load. The [website-memory] lines just before each fatal read ~1.95 GB used with hundreds of sessions (269, 190, 441) under a bot flood, so the load allocation is only the straw that crosses the line; the real growth is elsewhere (accumulating sessions/connections, and PackedTableTools' own table_cache which has no eviction are the leading suspects). The same logs carried ~8000 deprecation and warning lines, nearly all from one bug: